This page last changed on May 13, 2009 by kgomes.

In order to read in data from the ESP, the GUI will use the ESP's log (real.log) file as the official 'interface' for data collection. In order to facilitate this, this page documents what the entries in the log file should look like so that the ESP GUI will not have to make extensive and fragile rules to try and interpret the data. The esp gui log data should have the following format in the context the raw log file:

EVENT-NAME,attribute=value,...

Notes:

  1. Time is designated using epoch seconds (number of seconds that have elapsed since January 1, 1970) in GMT
  2. EVENT_NAME is one of the following:
    1. BEGIN_MISSON
    2. PHASE_START
    3. PHASE_END
    4. PROTOCOL_START
    5. PROTOCOL_END
    6. SAMPLE_START
    7. SAMPLE_END
    8. CAMERA_SNAP
    9. END_MISSION
  3. Attributes are key=value pairs and vary from event to event. Attributes for the various events are:
    1. BEGIN_MISSON
      1. No attributes
      2. Example: BEGIN_MISSION
    2. PHASE_START
      1. phase_name=XXXXXX (e.g. hab, larv, da, habda)
      2. Example: PHASE_START,phase_name=hab
    3. PHASE_END
      1. phase_name=XXXXXX (e.g. hab, larv, da, habda)
      2. phase_start=EPOCH_SECONDS (this is the time that the phase started. This is necessary due to the fact there are multiple threads the name & start date are the unique key.)
      3. Example: PHASE_END,phase_name=hab,phase_start=1231372399
    4. PROTOCOL_START
      1. phase_name=XXXXXX (e.g. hab, larv, da, habda)
      2. phase_start=EPOCH_SECDONDS
      3. protocol_name=PPPPP (e.g. sh1, sh2, wcr)
      4. Example: PROTOCOL_START,phase_name=hab,phase_start=1231372399,protocol_name=sh1
    5. PROTOCOL_END
      1. phase_name=XXXXXX (e.g. hab, larv, da, habda)
      2. phase_start=EPOCH_SECONDS
      3. protocol_name=PPPPP (e.g. sh1, sh2, wcr)
      4. protocol_start=EPOCH_SECONDS
      5. Example: PROTOCOL_END,phase_name=hab,phase_start=1231372399,protocol_name=sh1,protocol_start=1231372399
    6. SAMPLE_START
      1. phase_name=XXXXXX (e.g. hab, larv, da, habda)
      2. phase_start=YYYY-MM-DDThh:mm:ssZ
      3. protocol_name=PPPPP (e.g. sh1, sh2, wcr)
      4. protocol_start=EPOCH_SECONDS
      5. target_volume=ZZZZml
      6. Example: SAMPLE_START,phase_name=hab,phase_start=1231372399,protocol_name=sh1,protocol_start=1231372399,target_volume=1000ml
    7. SAMPLE_END
      1. phase_name=XXXXXX (e.g. hab, larv, da, habda)
      2. phase_start=EPOCH_SECONDS
      3. protocol_name=PPPPP (e.g. sh1, sh2, wcr)
      4. protocol_start=EPOCH_SECONDS
      5. sample_volume=ZZZZml
      6. Example: SAMPLE_END,phase_name=hab,phase_start=1231372399,protocol_name=sh1,protocol_start=1231372399,sample_volume=934.1ml
    8. CAMERA_SNAP
      1. phase_name=XXXXXX (e.g. hab, larv, da, habda)
      2. phase_start=EPOCH_SECONDS
      3. file_name=ZZZZZZZZZ.tif
      4. auto_exposure=AAAAAAAs
      5. Example: CAMERA_SNAP,phase_name=hab,phase_start=1231372399,file_name=bac08oct1716h450ml40s.tif,auto_exposure=123.4s
        Actual log entries

        Rich made the changes to the ruby code to generate the log entries in the following format:

        1. protocol/BAC.rb
          1. Thread.log.data "BAC_BACSH1_START"
          2. Thread.log.data "BAC_BACSH1_START"
          3. Thread.log.data "BAC_SHORTBACSH2_START"
          4. Thread.log.data "BAC_SHORTBACSH2_END"
          5. Thread.log.data "BAC_PHASE_START"
          6. Thread.log.data "BAC_PHASE_END"
        2. protocol/samplepass.rb
          1. Thread.log.data "SAMPLEPASS_LYFIL_START"
          2. Thread.log.data "SAMPLEPASS_LYFIL_END"
        3. protocol/PUFM.rb
          1. Thread.log.data "PUFM_START"
          2. Thread.log.data "PUFM_END"
          3. Thread.log.data "PUFM_WITHINITIALPURGE_START"
          4. Thread.log.data "PUFM_WITHINITIALPURGE_END"
        4. protocol/HAB.rb
          1. Thread.log.data "HAB_HABSH1_START"
          2. Thread.log.data "HAB_HABSH1_END"
          3. Thread.log.data "HAB_SHORTHABSH2_START"
          4. Thread.log.data "HAB_SHORTHABSH2_END"
          5. Thread.log.data "HAB_PHASE_START"
          6. Thread.log.data "HAB_PHASE_END"
        5. protocol/wcr.rb
          1. Thread.log.data "WCR_PROTOCOL_START," + " volume=#{sampleVolume}"
          2. Thread.log.data "WCR_PROTOCOL_END"
        6. protocol/DA.rb
          1. Thread.log.data "DA_DAEXTRACT_START"
          2. Thread.log.data "DA_DAEXTRACT_END"
          3. Thread.log.data "DA_START"
          4. Thread.log.data "DA_END"
          5. Thread.log.data "DA_SHORTDA_START"
          6. Thread.log.data "DA_SHORTDA_END"
          7. Thread.log.data "DA_HAB4DA_START"
          8. Thread.log.data "DA_HAB4DA_END"
          9. Thread.log.data "DA_HABDA_START"
          10. Thread.log.data "DA_HABDA_END"
        7. protocol/utilities.rb
          1. Thread.log.data "PROTOCOLARGS, assay=#{opts[:assay]}, maxvolume=#{sampleVolume.first}, wcrmaxvolume=#{sampleVolume.last}"
          2. Thread.log.data "INITIALPURGE_START"
          3. Thread.log.data "INITIALPURGE_END"
          4. Thread.log.data "FINALPURGE_START"
          5. Thread.log.data "FINALPURGE_END"
        8. protocol/LARV.rb
          1. Thread.log.data "LARV_LARVSH1_START"
          2. Thread.log.data "LARV_LARVSH1_END"
          3. Thread.log.data "LARV_SHORTLARVSH2_START"
          4. Thread.log.data "LARV_SHORTLARVSH2_END"
          5. Thread.log.data "LARV_PHASE_START"
          6. Thread.log.data "LARV_PHASE_END"
          7. Thread.log.data "LARV_PHASE_WITHPURGE_START"
          8. Thread.log.data "LARV_PHASE_WITHPURGE_END"
        9. protocol/sh2.rb
          1. Thread.log.data "SH2_PROTOCOL_START"
          2. Thread.log.data "SH2_PROTOCOL_END"
          3. Thread.log.data "SH2_SHORTSH2_START"
          4. Thread.log.data "SH2_SHORTSH2_END"
          5. Thread.log.data "SH2_SH2CORE_START, phase=#{phase},label=#{label}"
          6. Thread.log.data "SH2_SH2CORE_END"
        10. protocol/sh1.rb
          1. Thread.log.data "SH1_PROTOCOL_START"
          2. Thread.log.data "SH1_PROTOCOL_END"
          3. Thread.log.data "SH1_COLLECTSAMPLE, " + "volume=#{sampleVolume}, bubblepoint=#{collectionSampler.bubblePt}"
          4. Thread.log.data "SH1_COLLECTSAMPLE_COMPLETE"
          5. Thread.log.data "SH1_LYSING, volume=#{lysisVolume},solution=#{lysisSolution}"
        11. protocol/MFB.rb
          1. Thread.log.data "MFB_MFBSH1_START"
          2. Thread.log.data "MFB_MFBSH1_END"
          3. Thread.log.data "MFB_START"
          4. Thread.log.data "MFB_END"
        12. protocol/KAR.rb
          1. Thread.log.data "KAR_KARSH1_START"
          2. Thread.log.data "KAR_KARSH1_START"
          3. Thread.log.data "KAR_SHORTKARSH2_START"
          4. Thread.log.data "KAR_SHORTKARSH2_END"
          5. Thread.log.data "KAR_PHASE_START"
          6. Thread.log.data "KAR_PHASE_END"
        13. lib/esp.rb
          1. Thread.log.data "LIB_ESP_IRB_START, string=" + $0
          2. Thread.log.data "LIB_ESP_CONFIG,instrumentname=#{Name}, cfgpath=#{ConfigPath}"
          3. Thread.log.data "LIB_ESP_IRB_END"
          4. Thread.log.data "LIB_ESP_APPLICATION_START, string=" + $0
          5. Thread.log.data "LIB_ESP_CONFIG, instrumentname=#{Name}, cfgpath=#{ConfigPath}"
          6. Thread.log.data "LIB_ESP_APPLICATION_END"
        14. lib/cmdserver.rb
          1. Thread.log.data "LIB_CMDSERVER_ABORTMISSION" + reason
          2. Thread.log.data "CAMERA_SNAP, " + "string=#{instance}: #{SNAP} #{args}"
          3. Thread.log.data "CAMERA_OUTPUT_" + myn.to_s + ", string= " + line

            above should expand to:

                  CAMERA_OUTPUT_1, string=Starlight Xpress HX9/16: 1392x1040 pixel 16-bit CCD camera
                  CAMERA_OUTPUTA_2, string=Exposing 348x260 pixel 16-bit image for 25.668 seconds
                  CAMERA_OUTPUT_3, string=/var/log/rich/larv07oct3015h50ml2.5s.tif: TIFF Upload Complete
            
        15. utils/puckmoves.rb
          1. Thread.log.data "PUCKMOVES_LOADCLAMP, " +

            above expand to:

            PUCKMOVES_UNLOADCLAMP, source= , pucknumber= ,tube= , clamp=
            
          2. Thread.log.data "PUCKMOVES_LOADCLAMP_EMPTYTUBE, tube=#{tube}"
          3. Thread.log.data "PUCKMOVES_UNLOADCLAMP, " + guiMsg % [source.label, clamp.name, toTube]

            above expand to:

            PUCKMOVES_UNLOADCLAMP, source= , clamp= , tube=
            
        16. utils/misc.rb
          1. Thread.log.data "MISC_STORAGE_SELECTTUBE_TO"
          2. Thread.log.data "MISC_STORAGE_SELECTTUBE"
          3. Thread.log.data "MISC_STORAGE_SRCTUBE, tube=" + startingTube.to_s
          4. Thread.log.data "MISC_SRCTUBE"
          5. Thread.log.data "MISC_DSTTUBE"
        17. utils/sampler.rb
          1. Thread.log.data "SAMPLER_SAMPLED, " + "volume=%.1f" % sampledVol
        18. mission/08sep.rb
          1. Thread.log.data "MISSION_START, esp=#{ESP::Name}, mission=#{ESP::Mission}, starttube=#{startTube}, fromtube=#{fromTube}"
          2. Thread.log.data "MISSION_END, esp=#{ESP::Name}, mission=#{ESP::Mission}"
        Above was changed

        Essentially the message are the same, but Brent pulled the method calls into a :protocol method defined in utils.rb so the individual protocols don't have to do anything specific.

See the new page I just added about parsing these entries on the context of the raw log file.

These entries may be defined any way you like

I don't see how "phases" can have names.  A phase is a sequence of protocols.

Generally, the ESP sleeps between phases. 

I like the key=value format, but please try to shorten the key names a bit. This log file is too big as it is.

I kind of like the idea of units suffixes, if you really intend to parse them. But, if you are just going to ignore them,

I'd rather omit them entirely. That means, the data manager has to know that 1L == 1000ml

Are you up for that?

Posted by brent at Jan 07, 2009 22:49
Document generated by Confluence on Feb 03, 2026 14:16